#!/usr/bin/env python
# -*- coding: utf-8 -*-
# created at 03.04.2011

# This software is distributed under the BSD license.
# http://www.opensource.org/licenses/bsd-license.php 
# Copyright © 2011, Oleg Churkin

"""
Few unit tests for 'easylogger' package.
"""

__version__ = "0.1"

import re
import sys
import unittest
import cStringIO

sys.path.append("..") # to avoid import error
import easylogger

SKIP = "..."

class Test(unittest.TestCase):

    # to support Python 2.6
    def assertRegexpMatches(self, text, expected_regexp, msg=None):
        """Fail the test unless the text matches the regular expression."""
        if isinstance(expected_regexp, basestring):
            expected_regexp = re.compile(expected_regexp)
        if not expected_regexp.search(text):
            msg = msg or "Regexp didn't match"
            msg = '%s: %r not found in %r' % (msg, expected_regexp.pattern, text)
            raise self.failureException(msg)

    def setUp(self):
        self.required_output = [SKIP] * 50
        self.stream = cStringIO.StringIO()
        easylogger.log = easylogger.get_default_logger(self.stream)

    def tearDown(self):
        if self.required_output is not None:
            self.compare_output(self.split_output(), self.required_output)

    def split_output(self):
        """Splitting logger's output."""
        return self.stream.getvalue().strip().split("\n")

    def compare_output(self, received, requested):
        """Both parameters must be lists."""
        print "=" * 80
        for n, _ in enumerate(received):
            print _
            requsted_string = requested[n]
            if requsted_string == SKIP:
                continue
            
            if SKIP in requsted_string:
                requsted_string = re.escape(requsted_string).replace(re.escape(SKIP), ".*?")
                self.assertRegexpMatches(_, requsted_string,
                                         "Wrong output was produced by logger: " + _)
            else:
                self.assertTrue(_.endswith(requested[n]), 
                                "Wrong output was produced by logger: " + repr(_) +
                                " expected: " + repr(requested[n]))
                
    
    #----------------------------------------------------------- Tests are below
                
    def test_basic_facilities(self):
        from easylogger import log, info, debug, DEBUG #IGNORE:W0404
        messages = ["Hello, World!",
                    "This is an information message",
                    "This is a debug message",
                    "This is an error message",
                    "This is an critical message",
                    "Hello!",
                    "Bye!",
                    "This is a warning message.",
                    "[DEBUG   ] Generic log method.",
                    "[DEBUG   ] 1 2 3 4",
                    "Error message produced via exception method."]
        
        messages.extend([SKIP] * 10)
        
        log(messages[0])
        log.info(messages[1])
        log.debug(messages[2])
        log.error(messages[3])
        log.critical(messages[4])
        info(messages[5])
        debug(messages[6])
        log.warning(messages[7])
        log.log(DEBUG, messages[8][11:])
        log(1, 2, 3, 4)
        
        try:
            raise Exception("Dummy exception")
        except:
            log.exception(messages[10])
 
        self.required_output = messages
    
    def test_different_logging_levels(self):
        from easylogger import log, DEBUG, INFO #IGNORE:W0404
        messages = ["Bye, World!",
                    "Hello, World!",
                    "Bye, World!",
                    "Error occurred!"]
        
        log.set_effective_level(DEBUG)
        log.info(messages[0])
        log.debug(messages[1])
        
        self.assertEqual(log.get_effective_level(), DEBUG, "Wrong effective level")
        
        log.set_effective_level(INFO)
        log.debug(messages[1])
        log.info(messages[0])
        log.error(messages[3])
        
        self.assertEqual(log.get_effective_level(), INFO, "Wrong effective level")
        
        self.required_output = messages
        
    
    def test_several_loggers_simultaneously(self):
        from logging import StreamHandler
        from easylogger import get_logger, compose_handler, DEBUG, INFO #IGNORE:W0404
        
        messages = ["Hello, World!",
                    "Bye, World!"]
        
        message_format = ("%(asctime)s [%(levelname)s] (%(name)s) %(message)s", "%M:%S")
        stream_handler = compose_handler(StreamHandler(self.stream), level=DEBUG,
                                         format_tuple=message_format)
        log1 = get_logger("test.log1", handlers=[stream_handler])
        log2 = get_logger("test.log2", INFO, stream_handler)
        
        self.assertEqual(DEBUG, log1.get_effective_level(), "Wrong effective"
                         " log level for log1")
        self.assertEqual(INFO, log2.get_effective_level(), "Wrong effective"
                         " log level for log2")
        
        log1.info(messages[0])
        log1.debug(messages[1])
        
        log2.debug(messages[0]) # should not be shown
        log2.error(messages[0])
        log2.info(messages[1])
        
        self.required_output = ("[INFO] (test.log1) Hello, World!",
                                "[DEBUG] (test.log1) Bye, World!",
                                "[ERROR] (test.log2) Hello, World!",
                                "[INFO] (test.log2) Bye, World!")

    def test_decorator_usage(self):
        
        from easylogger import critical, error, warning, log
        from testdata import hello, MyClass
        
        log.set_options(enable_doc_processing=False)
        
        hello(1, 2, c=3)
        critical("The importance of this message is 'critical'.")

        MyClass().get_major(hello1=u"世界")
        error("Error occurred!")
        
        MyClass().get_minor()
        warning("Please attention!")
        
        MyClass.static_method(1, "a", 55666, -90, int)
        log(MyClass.class_method(0))
        
        self.required_output = (
            "[CRITICAL] Executing function hello(a=1, b=2, c=3,...",
            "[CRITICAL] The importance of this message is 'critical'.",
            "[ERROR   ] Executing method MyClass.get_major(...).",
            "[ERROR   ] Error occurred!",
            "[WARNING ] Executing method MyClass.get_minor().",
            "[WARNING ] Please attention!",
            "[ERROR   ] Executing function static_method(a=1, b='a', c=55666, d=-90, e=<... 'int'>).",
            "[DEBUG   ] Executing method MyClass.class_method(t=0, r=1).",
            "[DEBUG   ] new class")
        
    def test_options_doc_processing(self):
        
        from easylogger import log, LoggingOptions, INFO
        import testdata
        import imp
        
        # to support Python 3.X
        if hasattr(imp, "reload"):
            reload = imp.reload
            
        reload(testdata) # to force reload of decorators
        from testdata import hello, MyClass, doc_string_test1, doc_string_test2
        
        # default behavior: doc processing is enabled
        
        doc_string_test1() 
        
        # disable doc processing
        log.set_options(enable_doc_processing=False)
        hello(1, 5, 6, qwerty="hello")
        
        # enable doc processing and set new processing prefix
        new_options = LoggingOptions()
        new_options.enable_doc_processing = True
        new_options.doc_processing_prefix = "## "
        log.set_options(new_options)
        doc_string_test1(12345)
        
        # change doc processing level
        log.set_options(doc_processing_level=INFO, doc_processing_prefix=None)
        MyClass().get_major(hello1=123)
        doc_string_test2(1, "ggg", name="wheel", key="hi")
        MyClass.class_method(1, r="2")
        MyClass().get_minor()
        MyClass.static_method(2, 3, 4, 5, 6)
        
        
        self.required_output = (
            "[INFO    ] Executing function doc_string_test1(h=None).",
            "[DOC     ] First line.",
            "[DOC     ] Seconds line.",
            "[DOC     ] ## Third line.",
            "[DOC     ] ## Forth line.",
            "[DOC     ] Fifth line.",
            "[CRITICAL] Executing function hello(a=1, b=5, c=6, qwerty='hello', abra='cadabra').",
            "[INFO    ] Executing function doc_string_test1(h=12345).",
            "[DOC     ] Third line.",
            "[DOC     ] Forth line.",
            "[ERROR   ] Executing method MyClass.get_major(hello1=123, abc='cde').",
            "[INFO    ] Get major version.",
            "[ERROR   ] Executing function doc_string_test2(a=1, bb='ggg', name='wheel', key='hi', value='Good').",
            "[INFO    ] Check message formatting.",
            "[INFO    ] a is 1, bb is ggg, name is wheel,",
            "[INFO    ] key is hi, value is Good",
            "[DEBUG   ] Executing method MyClass.class_method(t=1, r='2').",
            "[INFO    ] Class Method is here.",
            "[WARNING ] Executing method MyClass.get_minor().",
            "[ERROR   ] Executing function static_method(a=2, b=3, c=4, d=5, e=6).",
            "[INFO    ] Hello,",
            "[INFO    ] static method. {a} {t}")
        
    def test_options_indent(self):
        
        from easylogger import log, info, debug
        
        log("Hello, World")
        self.assertTrue(log.options.indent is None, "Indent is not None.") #@UndefinedVariable
        log.set_options(indent=2)
        info(u"Привет, Мир!!")
        log.set_options(indent=6)
        debug(u"你好，世界！")
        log.set_options(indent="->")
        info(u"नमस्ते, दुनिया!")
        log.set_options(indent=None)
        log("Bye, World!")

        self.required_output = (
            "[DEBUG   ] Hello, World",
            "[INFO    ]   Привет, Мир!!",
            "[DEBUG   ]       你好，世界！",
            "[INFO    ] ->नमस्ते, दुनिया!",
            "[DEBUG   ] Bye, World!")
    
    def test_options_new_style(self):
        
        from easylogger import log, info, error, LoggingOptions
        
        # new message style
        log("Hello, World!", "test1", "test2")
        component = "brain"
        error("Error occurred in", component, "with code", 123, int)
        log.set_options(new_style_delimiter="_")
        log("brown", "fox", "jumps", "over", "lazy", "dog")
        
        # old message style
        opt = LoggingOptions()
        opt.enable_new_style = False
        log.set_options(opt)
        info("a %s %s", "b", "c")
        self.required_output = (
            "[DEBUG   ] Hello, World! test1 test2",
            "[ERROR   ] Error occurred in brain with code 123 <... 'int'>", # in PY3 it will be 'class'
            "[DEBUG   ] brown_fox_jumps_over_lazy_dog",
            "[INFO    ] a b c")        
    
    def test_stream_redirection(self):
        
        from easylogger import log, STDOUT, STDERR
        
        sys.stdout = log.get_stream(STDOUT)
        sys.stderr = log.get_stream(STDERR)
        
        print "Hello!"
        print "Hi!", "How are you?"
        print 
        log("Just a separator here.")
        print "I'm fine.", "Thanks!",
        print "How about you?"
        sys.stdout.flush()
        
        print >> sys.stderr, "Just a simple error."
        
        sys.stderr.writelines(["1\n", "2\n", "3"])
        sys.stderr.flush()
        sys.stderr.close()
        sys.stderr.write("Message is not shown!\n")
        
        sys.stdout = sys.__stdout__
        sys.stderr = sys.__stderr__
        
        self.required_output = (
            "[STDOUT  ] Hello!",
            "[STDOUT  ] Hi! How are you?",
            "[STDOUT  ] ", 
            "[DEBUG   ] Just a separator here.",
            "[STDOUT  ] I'm fine. Thanks! How about you?",
            "[STDERR  ] Just a simple error.",
            "[STDERR  ] 1",
            "[STDERR  ] 2",
            "[STDERR  ] 3")

    
    def test_play_with_handlers(self):
        
        from easylogger import get_logger, compose_handler, DEBUG
        from logging import StreamHandler, FileHandler
        import tempfile
        
        test_log = tempfile.mkstemp()[1]
        
        hstream = compose_handler(StreamHandler(self.stream),
                                  level=None, format_tuple="%(asctime)s (%(name)s) %(message)s",
                                  filter_name="basic")
        
        fstream = compose_handler(FileHandler(test_log, "w"),
                                  level=None, format_tuple="(%(name)s) %(message)s",
                                  filter_name=None)
        
        mylogger = get_logger("basic")
        mylogger.replace_handlers(hstream)
        mylogger("It's a brand new logger!")
        mylogger.error("I can write error messages!")
        self.assertEqual(DEBUG, mylogger.get_effective_level(),
                         "Default effective level should be 20 (DEBUG).")
        
        yourlogger = get_logger("advanced")
        yourlogger.append_handlers(hstream)
        yourlogger.info("This message should be filtered.")
        
        hislogger = get_logger("basic.advanced.hi")
        hislogger.replace_handlers(hstream)
        
        # must be shown twice, since message is propagated to parent logger
        hislogger.debug("Should not be filtered.")  

        mylogger.replace_handlers(hstream, fstream)
        # now write to file and console simultaneously
        mylogger.warning("System is shutting down!")
        
        with open(test_log) as f:
            content = f.readlines()
        
        self.stream.writelines(content)
        
        
        
        self.required_output = (
            "(basic) It's a brand new logger!",
            "(basic) I can write error messages!",
            "(basic.advanced.hi) Should not be filtered.",
            "(basic.advanced.hi) Should not be filtered.",
            "(basic) System is shutting down!",
            "(basic) System is shutting down!")

    def test_different_cases(self):
        
        # some negative cases here
        from easylogger import log

        # to support Python2.6        
        self.assertRaises(RuntimeError, log.set_options, 123, 321)
        
        self.assertRaises(TypeError, log.set_options, 123)
           
        self.assertRaises(AttributeError, log.set_options, unknown_option=90)

        # unicode check
        log(u"Hello", "World!")
        
        self.required_output = (
            "[DEBUG   ] Hello World!", )
    
    
    def test_check_generic_logging(self):
        
        # read prepared log config
        
        from easylogger import get_logger, INFO
        import logging.config
        import os
        
        sys.stdout = self.stream
        
        log_file = os.path.join(os.path.dirname(__file__), "logging.cfg")
        logging.config.fileConfig(log_file)
        mylog = get_logger("simpleExample", level=INFO)
        mylog.info("Hello!")
        mylog.debug("Hello!")
        mylog.error("Hello!")
        
        sys.stdout = sys.__stdout__

        self.required_output = (
            "simpleExample - INFO - Hello!",
            "simpleExample - ERROR - Hello!" )
        
    
if __name__ == "__main__":
    unittest.main()